Dec 03 16:09:28.120 INFO testing chttp-0.2.4 against master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61 for beta-1.31-5
Dec 03 16:09:28.121 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-1/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 16:09:28.466 INFO [stdout] 2b62b7ef89315be1c12b5cbd85e6bec6ca0d41768c767778b0f793e1624d6e08
Dec 03 16:09:28.471 INFO running `"docker" "start" "-a" "2b62b7ef89315be1c12b5cbd85e6bec6ca0d41768c767778b0f793e1624d6e08"`
Dec 03 16:09:29.604 INFO [stderr] usermod: no changes
Dec 03 16:09:29.891 INFO [stderr]    Compiling libnghttp2-sys v0.1.1
Dec 03 16:09:29.895 INFO [stderr]    Compiling curl-sys v0.4.15
Dec 03 16:09:29.901 INFO [stderr]    Compiling withers_derive v0.2.0
Dec 03 16:09:52.672 INFO [stderr]    Compiling curl v0.4.19
Dec 03 16:09:56.462 INFO [stderr]    Compiling chttp v0.2.4 (/source)
Dec 03 16:10:05.051 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 35.42s
Dec 03 16:10:05.063 INFO [stderr] su: No module specific data is present
Dec 03 16:10:06.203 INFO running `"docker" "inspect" "2b62b7ef89315be1c12b5cbd85e6bec6ca0d41768c767778b0f793e1624d6e08"`
Dec 03 16:10:06.541 INFO running `"docker" "rm" "-f" "2b62b7ef89315be1c12b5cbd85e6bec6ca0d41768c767778b0f793e1624d6e08"`
Dec 03 16:10:06.827 INFO [stdout] 2b62b7ef89315be1c12b5cbd85e6bec6ca0d41768c767778b0f793e1624d6e08
Dec 03 16:10:06.835 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-1/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 16:10:07.311 INFO [stdout] f80ad38f632e3ccd27263482c42d4b837437b72b5247cc9509ffac20c597afad
Dec 03 16:10:07.313 INFO running `"docker" "start" "-a" "f80ad38f632e3ccd27263482c42d4b837437b72b5247cc9509ffac20c597afad"`
Dec 03 16:10:08.615 INFO [stderr] usermod: no changes
Dec 03 16:10:08.983 INFO [stderr]    Compiling chttp v0.2.4 (/source)
Dec 03 16:10:56.020 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 47.36s
Dec 03 16:10:56.047 INFO [stderr] su: No module specific data is present
Dec 03 16:10:56.589 INFO running `"docker" "inspect" "f80ad38f632e3ccd27263482c42d4b837437b72b5247cc9509ffac20c597afad"`
Dec 03 16:10:56.873 INFO running `"docker" "rm" "-f" "f80ad38f632e3ccd27263482c42d4b837437b72b5247cc9509ffac20c597afad"`
Dec 03 16:10:57.179 INFO [stdout] f80ad38f632e3ccd27263482c42d4b837437b72b5247cc9509ffac20c597afad
Dec 03 16:10:57.187 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-1/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 03 16:10:57.612 INFO [stdout] d0a4e850b6ef7c7075896455c71312d6f7c712e2867d485de3626ac65b67b0b6
Dec 03 16:10:57.617 INFO running `"docker" "start" "-a" "d0a4e850b6ef7c7075896455c71312d6f7c712e2867d485de3626ac65b67b0b6"`
Dec 03 16:10:59.039 INFO [stderr] usermod: no changes
Dec 03 16:10:59.379 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.30s
Dec 03 16:10:59.395 INFO [stderr]      Running /target/debug/deps/chttp-4b6d5cf07c9b9e91
Dec 03 16:10:59.395 INFO [stdout] 
Dec 03 16:10:59.395 INFO [stdout] running 0 tests
Dec 03 16:10:59.395 INFO [stdout] 
Dec 03 16:10:59.395 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 16:10:59.395 INFO [stdout] 
Dec 03 16:10:59.399 INFO [stderr]      Running /target/debug/deps/redirects-b546a451877f12ff
Dec 03 16:10:59.403 INFO [stdout] 
Dec 03 16:10:59.403 INFO [stdout] running 3 tests
Dec 03 16:10:59.451 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: agent ready
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fc3ece51000, handler: 0x7fc3ece51000 }))
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request:   Trying 127.0.0.1...
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 41401 (#0)
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /a HTTP/1.1\r\nHost: 127.0.0.1:41401\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fc3ed0a4000, handler: 0x7fc3ed0a4000 }))
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [serially]
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Server doesn't support multi-use (yet)
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request:   Trying 127.0.0.1...
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38637 (#1)
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /0 HTTP/1.1\r\nHost: 127.0.0.1:38637\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fc3ecc4e000, handler: 0x7fc3ecc4e000 }))
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [serially]
Dec 03 16:10:59.473 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Server doesn't support multi-use (yet)
Dec 03 16:10:59.474 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request:   Trying 127.0.0.1...
Dec 03 16:10:59.474 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 34085 (#2)
Dec 03 16:10:59.474 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /a HTTP/1.1\r\nHost: 127.0.0.1:34085\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.474 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.483 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.487 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.496 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /1\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.499 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::request: preparing for redirect to Some("/1")
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:38637/1'
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [can pipeline]
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Could pipeline, but not asked to!
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38637 (#1)
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /1 HTTP/1.1\r\nHost: 127.0.0.1:38637\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /b\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #2 to host 127.0.0.1 left intact
Dec 03 16:10:59.499 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: request with token 2 completed
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /b\r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.499 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::request: preparing for redirect to Some("/b")
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:41401/b'
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [can pipeline]
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Could pipeline, but not asked to!
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Re-using existing connection! (#0) with host 127.0.0.1
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 41401 (#0)
Dec 03 16:10:59.499 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /b HTTP/1.1\r\nHost: 127.0.0.1:41401\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.500 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.539 INFO [stdout] test response_301_no_follow ... ok
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /2\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.544 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::request: preparing for redirect to Some("/2")
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:38637/2'
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [can pipeline]
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Could pipeline, but not asked to!
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38637 (#1)
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /2 HTTP/1.1\r\nHost: 127.0.0.1:38637\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n
Dec 03 16:10:59.544 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 2\r\n
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 32 bytes
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: buffer is empty, read is pending
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << ok
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received 2 bytes of data
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 32 bytes
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 2 bytes, consuming 2 bytes
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 30 bytes
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: buffer is empty, read is pending
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact
Dec 03 16:10:59.545 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: request with token 0 completed
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 30 bytes
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: request is closed, satisfying read request with EOF
Dec 03 16:10:59.545 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.546 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.546 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0)
Dec 03 16:10:59.546 INFO [stderr]  WARN 2018-12-03T16:10:59Z: chttp::internal::agent: received unpause request for unknown request token: 0
Dec 03 16:10:59.546 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0)
Dec 03 16:10:59.546 INFO [stderr]  WARN 2018-12-03T16:10:59Z: chttp::internal::agent: received unpause request for unknown request token: 0
Dec 03 16:10:59.546 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.551 INFO [stdout] test response_301_auto_follow ... ok
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /3\r\n
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.559 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::request: preparing for redirect to Some("/3")
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:38637/3'
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [can pipeline]
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Could pipeline, but not asked to!
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38637 (#1)
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /3 HTTP/1.1\r\nHost: 127.0.0.1:38637\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.559 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /4\r\n
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.579 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::request: preparing for redirect to Some("/4")
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:38637/4'
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [can pipeline]
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Could pipeline, but not asked to!
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38637 (#1)
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /4 HTTP/1.1\r\nHost: 127.0.0.1:38637\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.579 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /5\r\n
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.593 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::request: preparing for redirect to Some("/5")
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Issue another request to this URL: 'http://127.0.0.1:38637/5'
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7fc3eac5d060 [can pipeline]
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Could pipeline, but not asked to!
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Re-using existing connection! (#1) with host 127.0.0.1
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 38637 (#1)
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET /5 HTTP/1.1\r\nHost: 127.0.0.1:38637\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.593 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 301 Moved Permanently\r\n
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Location: /6\r\n
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 0\r\n
Dec 03 16:10:59.611 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::request: preparing for redirect to Some("/6")
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Maximum (5) redirects followed
Dec 03 16:10:59.611 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: curl error: [47] Number of redirects hit maximum amount
Dec 03 16:10:59.611 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 100ms
Dec 03 16:10:59.611 INFO [stderr]      Running /target/debug/deps/response-36add8ec0e5ac51e
Dec 03 16:10:59.611 INFO [stdout] test redirect_limit_is_respected ... ok
Dec 03 16:10:59.611 INFO [stdout] 
Dec 03 16:10:59.611 INFO [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 16:10:59.611 INFO [stdout] 
Dec 03 16:10:59.615 INFO [stdout] 
Dec 03 16:10:59.615 INFO [stdout] running 2 tests
Dec 03 16:10:59.619 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: agent ready
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7f2fbbaa4000, handler: 0x7f2fbbaa4000 }))
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7f2fb9e4e000, handler: 0x7f2fb9e4e000 }))
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request:   Trying 127.0.0.1...
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 44775 (#0)
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET / HTTP/1.1\r\nHost: 127.0.0.1:44775\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Found bundle for host 127.0.0.1: 0x7f2fb866c030 [serially]
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Server doesn't support multi-use (yet)
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request:   Trying 127.0.0.1...
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 44351 (#1)
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> GET / HTTP/1.1\r\nHost: 127.0.0.1:44351\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\n\r\n
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.619 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.667 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n
Dec 03 16:10:59.667 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 13000\r\n
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 32 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: buffer is empty, read is pending
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large 
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received 8047 bytes of data
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 32 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 8047 bytes, consuming 32 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 32 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 8015 bytes, consuming 32 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 64 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 7983 bytes, consuming 64 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 128 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 7919 bytes, consuming 128 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 256 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 7791 bytes, consuming 256 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 512 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 7535 bytes, consuming 512 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 1024 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 7023 bytes, consuming 1024 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 2048 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 5999 bytes, consuming 2048 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 4096 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 3951 bytes, consuming 3951 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 145 bytes
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: buffer is empty, read is pending
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1)
Dec 03 16:10:59.671 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1)
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large wow so large 
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received 4953 bytes of data
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 145 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 4953 bytes, consuming 145 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 8192 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 4808 bytes, consuming 4808 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 3384 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: buffer is empty, read is pending
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #1 to host 127.0.0.1 left intact
Dec 03 16:10:59.683 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: request with token 1 completed
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 3384 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: request is closed, satisfying read request with EOF
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(1)
Dec 03 16:10:59.683 INFO [stderr]  WARN 2018-12-03T16:10:59Z: chttp::internal::agent: received unpause request for unknown request token: 1
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << HTTP/1.1 200 OK\r\n
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Server: tiny-http (Rust)\r\n
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Date: Mon,  3 Dec 2018 16:10:59 GMT\r\n
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Type: text/plain; charset=utf8\r\n
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << Content-Length: 11\r\n
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 32 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: buffer is empty, read is pending
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << \r\n
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: << hello world
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received 11 bytes of data
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 32 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: read buffer contains 11 bytes, consuming 11 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 21 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: buffer is empty, read is pending
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connection #0 to host 127.0.0.1 left intact
Dec 03 16:10:59.683 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: request with token 0 completed
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: received read request for 21 bytes
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: request is closed, satisfying read request with EOF
Dec 03 16:10:59.683 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 100ms
Dec 03 16:10:59.684 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.684 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0)
Dec 03 16:10:59.684 INFO [stderr]  WARN 2018-12-03T16:10:59Z: chttp::internal::agent: received unpause request for unknown request token: 0
Dec 03 16:10:59.684 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: UnpauseWrite(0)
Dec 03 16:10:59.684 INFO [stderr]  WARN 2018-12-03T16:10:59Z: chttp::internal::agent: received unpause request for unknown request token: 0
Dec 03 16:10:59.687 INFO [stdout] test simple_response_body ... ok
Dec 03 16:10:59.691 INFO [stdout] test large_response_body ... ok
Dec 03 16:10:59.691 INFO [stdout] 
Dec 03 16:10:59.691 INFO [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 16:10:59.691 INFO [stdout] 
Dec 03 16:10:59.695 INFO [stderr]      Running /target/debug/deps/timeouts-6c7c9c3bef8d1ebc
Dec 03 16:10:59.695 INFO [stdout] 
Dec 03 16:10:59.695 INFO [stdout] running 1 test
Dec 03 16:10:59.700 INFO [stderr] DEBUG 2018-12-03T16:10:59Z: chttp::internal::agent: agent ready
Dec 03 16:10:59.700 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: received message from agent handle: BeginRequest(CurlRequest(Easy { handle: 0x7fe3456a4000, handler: 0x7fe3456a4000 }))
Dec 03 16:10:59.700 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request:   Trying 127.0.0.1...
Dec 03 16:10:59.700 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: Connected to 127.0.0.1 (127.0.0.1) port 40217 (#0)
Dec 03 16:10:59.700 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::request: >> POST / HTTP/1.1\r\nHost: 127.0.0.1:40217\r\nAccept: */*\r\nAccept-Encoding: deflate, gzip\r\nContent-Length: 11\r\nExpect: 100-continue\r\n\r\n
Dec 03 16:10:59.700 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.700 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: woke up from notify fd
Dec 03 16:10:59.700 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:10:59.903 INFO [stderr] TRACE 2018-12-03T16:10:59Z: chttp::internal::agent: polling with timeout of 200ms
Dec 03 16:11:00.098 INFO [stderr] TRACE 2018-12-03T16:11:00Z: chttp::internal::request: Done waiting for 100-continue
Dec 03 16:11:00.098 INFO [stderr] TRACE 2018-12-03T16:11:00Z: chttp::internal::agent: polling with timeout of 1s
Dec 03 16:11:00.098 INFO [stderr] TRACE 2018-12-03T16:11:00Z: chttp::internal::request: >> hello world
Dec 03 16:11:00.098 INFO [stderr] TRACE 2018-12-03T16:11:00Z: chttp::internal::request: We are completely uploaded and fine
Dec 03 16:11:00.098 INFO [stderr] TRACE 2018-12-03T16:11:00Z: chttp::internal::agent: polling with timeout of 1s
Dec 03 16:11:01.099 INFO [stderr] TRACE 2018-12-03T16:11:01Z: chttp::internal::request: Operation timed out after 2000 milliseconds with 0 bytes received
Dec 03 16:11:01.099 INFO [stderr] TRACE 2018-12-03T16:11:01Z: chttp::internal::request: Closing connection 0
Dec 03 16:11:01.099 INFO [stderr] DEBUG 2018-12-03T16:11:01Z: chttp::internal::agent: curl error: [28] Timeout was reached
Dec 03 16:11:01.099 INFO [stderr] TRACE 2018-12-03T16:11:01Z: chttp::internal::agent: polling with timeout of 100ms
Dec 03 16:11:01.100 INFO [stdout] test request_errors_if_read_timeout_is_reached ... ok
Dec 03 16:11:01.100 INFO [stdout] 
Dec 03 16:11:01.100 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 16:11:01.100 INFO [stdout] 
Dec 03 16:11:01.102 INFO [stderr]    Doc-tests chttp
Dec 03 16:11:09.048 INFO [stdout] 
Dec 03 16:11:09.048 INFO [stdout] running 6 tests
Dec 03 16:11:39.839 INFO [stdout] test src/lib.rs -  (line 37) ... ok
Dec 03 16:11:40.015 INFO [stdout] test src/client.rs - client::ClientBuilder (line 17) ... ok
Dec 03 16:11:41.819 INFO [stdout] test src/lib.rs -  (line 74) ... ok
Dec 03 16:11:42.027 INFO [stdout] test src/lib.rs -  (line 53) ... ok
Dec 03 16:11:42.782 INFO [stdout] test src/lib.rs -  (line 26) ... ok
Dec 03 16:11:42.895 INFO [stdout] test src/lib.rs -  (line 11) ... ok
Dec 03 16:11:42.895 INFO [stdout] 
Dec 03 16:11:42.895 INFO [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 03 16:11:42.895 INFO [stdout] 
Dec 03 16:11:42.918 INFO [stderr] su: No module specific data is present
Dec 03 16:11:43.544 INFO running `"docker" "inspect" "d0a4e850b6ef7c7075896455c71312d6f7c712e2867d485de3626ac65b67b0b6"`
Dec 03 16:11:43.847 INFO running `"docker" "rm" "-f" "d0a4e850b6ef7c7075896455c71312d6f7c712e2867d485de3626ac65b67b0b6"`
Dec 03 16:11:44.123 INFO [stdout] d0a4e850b6ef7c7075896455c71312d6f7c712e2867d485de3626ac65b67b0b6
